package net.butfly.bus.filter;

import net.butfly.bus.Error;
import net.butfly.bus.Request;
import net.butfly.bus.Response;
import net.butfly.bus.context.Context;
import net.butfly.bus.context.FlowNo;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class LoggerFilter extends FilterBase implements Filter {
	private final Logger logger = LoggerFactory.getLogger("net.butfly.bus");

	@Override
	public void execute(Request request, Response response) throws Exception {
		StringBuilder sb = new StringBuilder("BUS").append("[").append(request.code()).append(":").append(request.version())
				.append("]").append("[").append(side.name()).append("]");
		FlowNo fn = Context.flowNo();
		if (null != fn)
			sb.append("[").append(fn.toString()).append("]");
		sb.append(":");
		long now = System.currentTimeMillis();
		String prefix = sb.toString();
		logger.info(prefix + " invoking begin...");
		logger.debug(prefix + getDebugDetail(request));
		try {
			super.execute(request, response);
		} finally {
			long spent = System.currentTimeMillis() - now;
			Error err = response.error();
			if (err != null)
				logger.error("Bus error: \n" + err.toString());
			logger.info(prefix + " invoking ended in [" + spent + "ms].");
		}
	}

	private String getDebugDetail(Request request) {
		StringBuilder sb = new StringBuilder();
		sb.append(" invoking request detail: ").append("\n\tcontext: ").append(Context.CURRENT.toString())
				.append("\n\ttx code: ").append(request.code()).append("\n\ttx version: ").append(request.version())
				.append("\n\trequest arguments: ");
		int ai = 1;
		if (request.arguments() != null)
			for (Object arg : request.arguments()) {
				sb.append("\n\t\t").append("[").append(ai++).append("]: ");
				if (null != arg)
					sb.append(arg).append("\n\t\t\t").append("[").append(arg.getClass().getName()).append("]");
				else
					sb.append("[NULL]");
			}
		else
			sb.append("[NULL]");
		return sb.toString();
	}
}
